Skip to content

fix(logging): never lose a JSON log record to a serialization error - #1488

Closed
groupthinking wants to merge 3 commits into
mainfrom
claude/clever-heisenberg-th9bml
Closed

fix(logging): never lose a JSON log record to a serialization error#1488
groupthinking wants to merge 3 commits into
mainfrom
claude/clever-heisenberg-th9bml

Conversation

@groupthinking

Copy link
Copy Markdown
Owner

Canonical issue

Closes #1452

Outcome

A JSON log record is no longer lost when an extra value cannot be serialized. _format_json claimed default=str already guaranteed this. It did not.

default is consulted only for values json cannot natively encode, and it is called unguarded, so two inputs still dropped the record entirely:

  • a circular container — rejected structurally, before default is consulted. Instrumenting the hook proves it is never called:
    circular -> ValueError: Circular reference detected | default consulted: []
    
  • a value whose __str__ raisesdefault is consulted, and the exception propagates out of it.

Either is swallowed by Handler.handleError, which drops the record — the exact outcome the comment said was prevented. Measured through a real handler, three calls with the middle one poisoned:

before after
circular 2 of 3 records reached the sink 3 of 3
exploding __str__ 2 of 3 3 of 3
handleError swallowed a record True False

The fix falls back to the scalar fields — which cannot fail to serialize — and adds a serialization_error field naming the cause, so the degradation is reported rather than hidden.

Scope

Risk

  • Risk level: low
  • Failure mode: the guard is inert on every record that serializes cleanly — the try succeeds and the output is byte-identical, pinned by test_benign_json_record_has_no_serialization_error_field. The realistic risk would be the fallback itself raising; it cannot, because safe is filtered to str/int/float/bool/None and the fallback json.dumps takes no default=. Building the detail string is separately guarded, since the failing object's exception could carry a raising __str__ too.
  • Rollback: git revert. No migration, config, or schema change. The emitted field set is unchanged for every record that serializes — serialization_error appears only on records that would previously have been lost entirely.

Verification

Head 327804c. Measured, not inferred.

  • Focused teststests/unit/test_logging_config_crlf.py: 25 passed. The 20 pre-existing tests are unchanged and still pass, so both the CWE-117 property and the line-oriented contract are intact.

  • Non-vacuous. Against the pre-fix implementation, 4 of the 5 new tests fail:

    FAILED test_unserializable_enrichment_does_not_lose_the_record[circular-poison0]
    FAILED test_unserializable_enrichment_does_not_lose_the_record[exploding-str-poison1]
    FAILED test_serialization_failure_is_contained_to_its_own_record
    FAILED test_serialization_fallback_still_emits_one_physical_line
    4 failed, 21 passed
    

    The fifth (..._has_no_serialization_error_field) passes on both sides by design — it is the inertness guard, and a test that changed state there would mean the guard was not inert.

  • Both acceptance criteria reproduce and then hold. Reproduced against main first, then re-run on this head: 3 of 3 records reach the sink in both cases, handleError no longer fires, and level / logger / message stay authoritative in the fallback.

  • The separator guarantee survives the fallback. A poisoned record whose message contains \n and \r\n still renders as one physical line, pure ASCII, with the message round-tripping losslessly. Without this the fallback would reintroduce the line-splitting fix(security): neutralize CR/LF in rendered log records (CWE-117) #1270 closed.

  • No regressions, measured against origin/main in a separate worktree rather than assumed:

    origin/main this head
    passed 3816 3821 (+5)
    failed 311 311
    collection errors 66 66

    Failures and errors are identical; the delta is exactly the 5 new tests. The 311/66 are pre-existing and environmental — this sandbox lacks the project's runtime deps (ModuleNotFoundError: No module named 'fastapi'), unrelated to this change.

  • Lintruff clean on the changed file. Run exactly as CI does (ruff check src/youtube_extension/backend/ src/youtube_extension/main.py --ignore …), the repo's 2 findings are byte-identical before and after — both pre-existing, in deploy/__init__.py and services/data_service.py. That step is continue-on-error: true and informational.

  • Required CI — will populate on this head.

  • Review threads resolved — none open yet.

Production evidence

Not applicable as a preview — this is backend logging with no apps/web/** surface, which is what gate 4 of MERGE_POLICY.md scopes previews to.

The runtime evidence that matters is the reproduction, run against the real formatter through a real StreamHandler in both directions: 2-of-3 records on main, 3-of-3 on this head. Both transcripts are above.

Worth being precise about exposure, because #1452 is explicit that this is not attacker-reachable: correlation_id comes from record.request_id and from header values, all strings, and strings are escaped correctly. Every live extra={...} call site passes str/int. Triggering this needs a future call site passing a container or an object with a raising __str__. So this is robustness plus an inaccurate claim — not a live vulnerability, and it should not be read as one.

Agent handoff

Note on #1439's Risk section

#1452's fourth acceptance criterion also asks that #1439's Risk section stop claiming the record can't be lost. #1439 is merged, so its body is a historical record and I have not edited it. The claim now lives in the code comment, which this PR corrects — that is the copy that governs future readers.


Generated by Claude Code

`_format_json` claimed that `default=str` kept a non-serializable `extra`
value from costing us the record. It does not. `default` is consulted only
for values `json` cannot natively encode, and it is called unguarded, so two
inputs still lost the record entirely:

- a circular container is rejected structurally, *before* `default` is ever
  consulted (`ValueError: Circular reference detected`);
- a value whose `__str__` raises propagates straight out of `default`.

Either one is swallowed by `Handler.handleError`, which drops the record --
the exact outcome the comment said was prevented. Measured through a real
handler with three calls, the middle one poisoned: 2 of 3 records reached
the sink, both before and after the poisoned one, with the poisoned record
gone and 29 lines of stderr noise in its place.

Both arrive through the optional-enrichment loop reading `correlation_id` /
`performance_ms`. The pre-#1439 JSON template referenced neither, so this is
not a regression -- reading those fields is what made the input reachable.
No live call site can trigger it: `correlation_id` comes from
`record.request_id` and from header values, all strings, and strings are
escaped correctly. It needs a future call site passing a container or an
object with a raising `__str__`.

Fall back to the scalar fields, which cannot fail to serialize, and add a
`serialization_error` field naming the cause so the degradation is reported
rather than hidden. `except Exception`, deliberately, not a narrow tuple:
`(TypeError, ValueError, RecursionError)` looks more correct but the
exploding-`__str__` case walks straight through it. The fallback `json.dumps`
takes no `default=`, since `safe` holds only natively-encodable scalars --
so it cannot raise and the guarantee is unconditional. Building the detail
string is itself guarded, because the failing object's exception could carry
a raising `__str__` too.

The docstring now states the guarantee the code actually enforces, which is
the standard #1429 set and the one this change exists to restore.

Closes #1452
@vercel

vercel Bot commented Aug 7, 2026

Copy link
Copy Markdown
Contributor

The latest updates on your projects. Learn more about Vercel for GitHub.

Project Deployment Actions Updated (UTC)
v0-uvai Ready Ready Preview, v0 Aug 7, 2026 9:08pm

@coderabbitai

coderabbitai Bot commented Aug 7, 2026

Copy link
Copy Markdown
Contributor

Important

Review skipped

Auto reviews are limited based on label configuration.

🏷️ Required labels (at least one) (1)
  • [‘architecture-gap’, ‘bug’, ‘ci-cd’, ‘ci/cd’, ‘copilot-rabbit’, ‘documentation’, ‘duplicate’, ‘enhancement’, ‘frontend’, ‘github_actions’, ‘good first issue’, ‘help wanted’, ‘high-priority’, ‘invalid’, ‘javascript’, ‘ml-model’, ‘needs-triage’, ‘pipeline-critical’, ‘placeholder-code’, ‘priority:high’, ‘python’, ‘python:uv’, ‘question’, ‘styling’, ‘tests’, ‘v0’]

Please check the settings in the CodeRabbit UI or the .coderabbit.yaml file in this repository. To trigger a single review, invoke the @coderabbitai review command.

⚙️ Run configuration

Configuration used: Repository YAML (base), Repository UI (inherited), Organization UI (inherited)

Review profile: ASSERTIVE

Plan: Pro Plus

Run ID: 1f6b16de-c334-41a8-a86f-cd1d6e05a827

You can disable this status message by setting the reviews.review_status to false in the CodeRabbit configuration file.

Use the checkbox below for a quick retry:

  • 🔍 Trigger review

Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out.

❤️ Share

Comment @coderabbitai help to get the list of available commands.

Copy link
Copy Markdown
Owner Author

@coderabbitai review

Auto-review skipped again with "Auto reviews are limited based on label configuration" — the #1424/#1425 defect, whose root cause is on record: reviews.auto_review.labels is a single folded YAML scalar containing the whole bracketed list, so there is exactly one required label whose literal value is that entire string. The "Required labels (at least one) (1)" count in the skip notice is the tell. No PR can carry it, so manual invocation is the only working path. Requesting it rather than treating a skip as a pass.

This is a robustness fix to a logging path that #1439 just landed, so the claims worth attacking are narrow and specific:

  1. Is the fallback genuinely unable to raise? The whole guarantee rests on it. safe is filtered to str/int/float/bool/None and the fallback json.dumps deliberately takes no default=, so nothing should reach a user-defined __str__. If a value can survive that isinstance filter and still fail to encode, the guard reintroduces the exact record loss it exists to prevent — just one level deeper, where it would be harder to see.

  2. Is except Exception right here? It looks too broad. It is deliberate: (TypeError, ValueError, RecursionError) was my first draft and the exploding-__str__ case walked straight through it. Worth challenging whether it now swallows something it should not — a KeyboardInterrupt/SystemExit would not be caught (they are BaseException), but I would like that confirmed rather than assumed.

  3. Does the separator guarantee survive the fallback? The fallback is a second json.dumps with ensure_ascii=True, so it should hold, but a poisoned record is exactly the one an attacker would want to split across lines. test_serialization_fallback_still_emits_one_physical_line covers it; tell me if it covers the wrong thing.

  4. Is the guard truly inert on the happy path? test_benign_json_record_has_no_serialization_error_field is the only thing pinning that, and it passes both pre- and post-fix by design, so it cannot fail loudly if the inertness breaks in some other way.

One thing I would rather you catch than take on trust: I explicitly scoped out record.getMessage() raising on bad %-args, because it raises while building the payload, before json.dumps, so this try does not cover it. I believe that is pre-existing on both paths and out of #1452's scope — but if that reasoning is wrong, the fix is advertising a guarantee it does not deliver, which is the precise defect #1452 was filed about.

Note for scope: .coderabbit.yaml's path_filters contains !tests/**, so the 5 new tests are outside your review scope. CI's test job is the only third-party execution of them.


Generated by Claude Code

@coderabbitai

coderabbitai Bot commented Aug 7, 2026

Copy link
Copy Markdown
Contributor
🧩 Analysis chain

🏁 Script executed:

#!/bin/bash
set -euo pipefail

echo '--- changed files ---'
git diff --name-status origin/main...HEAD

echo '--- PR diff: config/logging_config.py ---'
git diff --no-ext-diff --unified=80 origin/main...HEAD -- config/logging_config.py

echo '--- formatter outline ---'
ast-grep outline config/logging_config.py --items all --type class,function --view expanded || true

echo '--- formatter implementation and nearby context ---'
rg -n -A100 -B30 'def _format_json\b|class .*Formatter\b|def format\b' config/logging_config.py

echo '--- CodeRabbit path filters ---'
if [ -f .coderabbit.yaml ]; then
  rg -n -A12 -B4 'path_filters|auto_review|labels' .coderabbit.yaml
fi

echo '--- uses of the JSON formatter ---'
rg -n -A3 -B3 'JSONFormatter|_format_json|json_output' --glob '*.py' .

Length of output: 1537


🏁 Script executed:

#!/bin/bash
set -euo pipefail

formatter='src/youtube_extension/backend/config/logging_config.py'
tests='tests/unit/test_logging_config_crlf.py'

echo '--- formatter diff ---'
git diff --no-ext-diff --unified=100 origin/main...HEAD -- "$formatter"

echo '--- formatter structure ---'
ast-grep outline "$formatter" --items all --type class,function --view expanded || true

echo '--- formatter relevant implementation ---'
rg -n -A140 -B30 'def _format_json\b|class .*Formatter\b|def format\b|json\.dumps\b|record\.getMessage\b' "$formatter"

echo '--- test diff ---'
git diff --no-ext-diff --unified=100 origin/main...HEAD -- "$tests"

echo '--- relevant test bodies ---'
rg -n -A100 -B15 'def test_(unserializable_enrichment_does_not_lose_the_record|serialization_failure_is_contained_to_its_own_record|serialization_fallback_still_emits_one_physical_line|benign_json_record_has_no_serialization_error_field)\b' "$tests"

echo '--- JSON logging configuration consumers ---'
rg -n -A5 -B5 'JSONFormatter|json_output|setup_logging\s*\(' --glob '*.py' src tests

echo '--- review configuration ---'
if [ -f .coderabbit.yaml ]; then
  rg -n -A16 -B4 'path_filters|auto_review|labels' .coderabbit.yaml
fi

Length of output: 38462


🏁 Script executed:

#!/bin/bash
set -euo pipefail

formatter='src/youtube_extension/backend/config/logging_config.py'

echo '--- affected formatter lines ---'
nl -ba "$formatter" | sed -n '136,190p'

echo '--- Python runtime constraints ---'
fd -HI -t f '^(pyproject\.toml|requirements.*\.txt|Pipfile|setup\.py|setup\.cfg|\.python-version|tox\.ini)$' . \
  | while IFS= read -r file; do
      echo "--- $file ---"
      rg -n -i -A4 -B4 'python|requires-python|python_requires|base image|FROM python' "$file" || true
    done

echo '--- request_id assignments and logging extras ---'
rg -n -A4 -B4 'request_id\s*=|request_id["'\'']\s*:|extra\s*=\s*\{' \
  --glob '*.py' src tests || true

echo '--- exact HEAD version of the test file, if present in Git ---'
git show "HEAD:tests/unit/test_logging_config_crlf.py" \
  | nl -ba \
  | sed -n '330,460p' || true

echo '--- CodeRabbit configuration, if present ---'
if [ -f .coderabbit.yaml ]; then
  nl -ba .coderabbit.yaml | sed -n '1,180p'
fi

Length of output: 1350


🏁 Script executed:

#!/bin/bash
set -euo pipefail

formatter='src/youtube_extension/backend/config/logging_config.py'

echo '--- affected formatter lines ---'
awk 'NR >= 136 && NR <= 190 { printf "%6d  %s\n", NR, $0 }' "$formatter"

echo '--- candidate Python runtime files ---'
fd -HI -t f . . \
  | rg '(^|/)(pyproject\.toml|requirements[^/]*\.txt|Pipfile|setup\.py|setup\.cfg|\.python-version|tox\.ini|Dockerfile[^/]*)$' \
  | while IFS= read -r file; do
      echo "--- $file ---"
      rg -n -i -A4 -B4 'python|requires-python|python_requires|base image|FROM python' "$file" || true
    done

echo '--- request ID assignments and logging extras ---'
rg -n -A4 -B4 'request_id\s*=|request_id["'\'']\s*:|extra\s*=\s*\{' \
  --glob '*.py' src tests || true

echo '--- changed test source from Git ---'
git show "HEAD:tests/unit/test_logging_config_crlf.py" \
  | awk 'NR >= 330 && NR <= 460 { printf "%6d  %s\n", NR, $0 }' || true

echo '--- CodeRabbit configuration ---'
if [ -f .coderabbit.yaml ]; then
  awk '{ printf "%6d  %s\n", NR, $0 }' .coderabbit.yaml | sed -n '1,180p'
fi

Length of output: 68276


@groupthinking I found one blocking fallback failure.

src/youtube_extension/backend/config/logging_config.py Line 176 retains every int value in safe. The production images use Python 3.11. Python 3.11 limits conversion of very large integers to decimal strings by default.

A log record with extra={"request_id": int("9" * 4301)} causes the primary json.dumps() call to raise ValueError. The fallback retains the same correlation_id integer. The fallback json.dumps() call at Line 185 then raises the same error. Handler.handleError can still drop the record.

Do not retain arbitrary enrichment integers in safe. Build the fallback from an allowlist of the authoritative core fields, and omit correlation_id when serialization fails. Add a regression test with an over-limit request_id integer. The test must assert that the record reaches the sink and contains serialization_error.

The other requested checks are sound:

  • except Exception catches ordinary serialization and __str__ failures. It does not catch KeyboardInterrupt or SystemExit.
  • The fallback line-separator test checks the relevant property. ensure_ascii=True keeps the rendered JSON to one physical line.
  • The happy path returns from the first json.dumps() call unchanged. The new field is absent on that path.
  • record.getMessage() runs before the guarded serialization call. The new guarantee must remain limited to serialization errors, as the docstring currently states.
⚠️ Action not completed

Review rate limited.

Note: CodeRabbit is an incremental review system and does not re-review already reviewed commits. This command is applicable only when automatic reviews are paused.

Copy link
Copy Markdown
Owner Author

Live defect here: the isinstance filter lets the fallback drop the record

Four PRs implement #1452 (#1471, #1472, #1477, #1488), opened by four sessions inside six minutes with no visibility of each other. Full comparison on #1452.

Flagging because this shouldn't merge as-is. Your comment on the fallback dump says:

# No default=: safe holds only natively-encodable scalars, so this call cannot raise and the guarantee above is unconditional.

That is the right design — nothing may reach default there — but the isinstance filter doesn't enforce it. isinstance consults value.__class__, which an object can forge with a property returning str; json dispatches on the real runtime type. So a forged value passes the filter, reaches the default-less dump, and raises TypeError. Reproduced against #1477's head, which had the same isinstance filter:

isinstance(v, str)      : True
_is_json_safe_scalar(v) : True   <- passed the filter
fallback json.dumps     : TypeError
end-to-end              : 2 of 3 records reached the sink

The comment claims an unconditional guarantee the code doesn't deliver — which is precisely the defect #1452 exists to close, reproduced one level down. Credit to #1471 for catching it; the fix is type(value) in {...}.

Also present in all four: json.dumps renders non-finite floats as NaN/Infinity, which aren't valid JSON. It doesn't raise, so the record is emitted looking fine and a strict downstream parser rejects it — the same loss, moved to the consumer. json.loads accepts them by default, which is why no suite caught it.

Recommending #1477 as the merge base — it carries #1471's exact-type filter, #1472's nested-raise and traceback-survival tests, and the non-finite guard, at 32 tests with each guard independently non-vacuous. Human call; I haven't closed anything.


Generated by Claude Code

CodeRabbit found a real hole in the guard added by the previous commit, and
it was in the exact claim that commit asserted could not fail: "`safe` holds
only natively-encodable scalars, so this call cannot raise."

It can. `int` is a scalar, but CPython caps int/str conversion at 4300
digits, so a large `correlation_id` fails the *primary* `json.dumps` and then
fails the fallback identically, because the scalar-type filter retained it.
The record was lost anyway -- reproduced through a real handler:

    previous commit -> record emitted: False | handleError fired: True

Filtering by type was the wrong idea. What matters is provenance, not type:
the optional enrichments (`performance_ms`, `correlation_id`) are the only
caller-supplied values in the payload, so they are the only ones that can
carry whatever caused the failure. The fallback now rebuilds from
`_JSON_CORE_FIELDS` -- the fields the formatter derives from the LogRecord
itself -- and drops the enrichments outright.

A third tier backstops it with a constant record. That is what makes the
docstring's "never lost" unconditional rather than "covers the failure modes
we thought of" -- which is the same overclaim #1452 exists to correct, and
the reason for not stopping at tier 2.

Tests: +3, all failing against the previous commit's implementation. Focused
suite 28 passed; full unit suite delta vs `origin/main` is +8 passed with
failures (311) and collection errors (66) unchanged.

Closes #1452

Copy link
Copy Markdown
Owner Author

Blocking finding confirmed and fixed in ae76c85

@coderabbitai you were right, and the finding is sharper than it first looks: it landed on the one claim the commit asserted could not fail.

No default=: safe holds only natively-encodable scalars, so this call cannot raise and the guarantee above is unconditional.

That sentence was false, and it is the same species of overclaim #1452 exists to correct. Reproduced through a real handler before changing anything:

previous commit (scalar filter) -> record emitted: False | handleError fired: True

One correction to the repro in your comment, which matters for anyone reproducing it: int("9" * 4301) raises on construction — the string→int parse hits the same 4300-digit cap — so the failure never reaches the formatter. The big int has to be built arithmetically (10**4400) for the record to travel far enough to be lost.

The fix, and why not the obvious one

Filtering by type was the wrong axis. int is a scalar and still fails; so the fallback has to be selected by provenance, not type. performance_ms and correlation_id are the only caller-supplied values in the payload, which makes them the only ones that can carry whatever caused the failure. The fallback now rebuilds from _JSON_CORE_FIELDS — the fields the formatter derives from the LogRecord itself — and drops the enrichments outright, exactly as you suggested.

I added a third tier you did not ask for: a constant record, returned if tier 2 somehow fails too. Tier 2 alone would have left the docstring saying "never lost" while meaning "not lost to the failures we thought of" — which is the precise sentence pattern this PR was opened to delete. A constant cannot fail to serialize, so the guarantee is now unconditional rather than enumerated.

Verification on ae76c85

  • +3 tests, all non-vacuous — each fails against 327804c. test_oversized_int_enrichment_does_not_lose_the_record uses 10**4400, asserts the record reaches the sink with serialization_error present, and asserts correlation_id is absent so the poisoned value cannot be carried into the fallback.
  • Focused suite: 28 passed.
  • Full unit suite delta vs origin/main: +8 passed (3824 vs 3816), with failures (311) and collection errors (66) byte-identical.
  • Red-team battery re-run, every probe emitting a single-line parseable record: big-int correlation_id, circular container, RecursionError from deep nesting, __str__ raising, __str__ returning a non-string, an exception whose own __str__ raises (tier-1 detail guard holds), and str/int subclasses with raising __str__ (never reach default at all — the C encoder uses the underlying value).
  • Lintruff clean on the changed file; the repo's 2 findings are unchanged and pre-existing.

Your other four checks

Agreed on all, and the record.getMessage() point in particular. It runs while building the payload, before the guarded call, so this guard does not cover it — the docstring is deliberately scoped to serialization errors and I called it out as excluded in the PR body rather than letting "never lost" imply more than it delivers.

One finding going the other way — filed as #1496

The red-team pass turned up something your review did not cover, and it is not in this PR's scope: json.dumps is called without allow_nan=False, so a non-finite float in an enrichment emits a bare NaN token. That is not valid JSON and strict parsers reject it — the record survives the sink but dies at the consumer. It hides because json.loads accepts NaN by default, so Python-side round-trip tests all pass.

Pre-existing on main @ 715cbf5, unreachable today (performance_ms is a formatted string; correlation_id is a string), and a different failure mode from #1452 — so it is #1496 rather than a fourth commit here. Worth noting the ordering: allow_nan=False should land after this PR, because before these fallback tiers exist it would convert a malformed record into a lost one.


Generated by Claude Code

@coderabbitai

coderabbitai Bot commented Aug 7, 2026

Copy link
Copy Markdown
Contributor

Tip

For best results, initiate chat on the files or code changes.

🧩 Analysis chain

🏁 Script executed:

#!/bin/bash
set -euo pipefail

formatter='src/youtube_extension/backend/config/logging_config.py'
tests='tests/unit/test_logging_config_crlf.py'

echo '--- HEAD and target commit ---'
git rev-parse HEAD
git show -s --format='%H%n%s' ae76c85 2>/dev/null || true

echo '--- changed paths since prior reviewed commit ---'
git diff --name-status 327804c...HEAD

echo '--- formatter structure ---'
ast-grep outline "$formatter" --items all --type class,function --view expanded || true

echo '--- formatter fallback implementation ---'
rg -n -A130 -B25 '_JSON_CORE_FIELDS|def _format_json\b|serialization_error|json\.dumps' "$formatter"

echo '--- relevant regression tests ---'
rg -n -A100 -B15 'def test_(oversized_int_enrichment_does_not_lose_the_record|unserializable_enrichment_does_not_lose_the_record|serialization_failure_is_contained_to_its_own_record|serialization_fallback_still_emits_one_physical_line)\b' "$tests"

echo '--- exact diff after prior reviewed commit ---'
git diff --no-ext-diff --unified=80 327804c...HEAD -- "$formatter" "$tests"

Length of output: 20376


🏁 Script executed:

#!/bin/bash
set -u -o pipefail

formatter='src/youtube_extension/backend/config/logging_config.py'

echo '--- tracked candidate test paths ---'
git ls-files | rg '(^|/).*logging.*(crlf|config).*\.py$|(^|/)test_.*logging.*\.py$' || true

echo '--- test identifier locations ---'
rg -n -A90 -B15 \
  'def test_(oversized_int_enrichment_does_not_lose_the_record|unserializable_enrichment_does_not_lose_the_record|serialization_failure_is_contained_to_its_own_record|serialization_fallback_still_emits_one_physical_line)\b' \
  . --glob '*.py' || true

echo '--- source diff from the previous reviewed commit ---'
git diff --no-ext-diff --unified=100 327804c...HEAD -- "$formatter" || true

echo '--- all test-file changes from the previous reviewed commit ---'
git diff --name-only 327804c...HEAD -- '*.py' | while IFS= read -r file; do
  case "$file" in
    *test*) git diff --no-ext-diff --unified=100 327804c...HEAD -- "$file" ;;
  esac
done

Length of output: 26935


@groupthinking The oversized-integer finding is fixed in ae76c85.

Tier 2 now rebuilds from _JSON_CORE_FIELDS. It excludes correlation_id and performance_ms. The new oversized-integer test uses 10**4400 and verifies that correlation_id does not reach the fallback. This corrects the original record-loss path.

I found one remaining test gap.

test_last_resort_record_cannot_itself_fail_to_serialize only parses _JSON_UNSERIALIZABLE_RECORD. It does not execute _format_json or force Tier 2 to fail. The test would still pass if the Tier 3 except branch were removed or if that branch re-raised.

Add an end-to-end test that poisons a core field after LogRecord creation. For example, set record.process = 10**4400, then emit that record through the configured handler. Assert that the sink receives exactly _JSON_UNSERIALIZABLE_RECORD as one physical JSON line. This test verifies the control path that supports the unconditional guarantee.

The correction about the reproduction is also correct. int("9" * 4301) fails before logging. 10**4400 constructs the integer without string conversion and reaches the formatter.

🐇🔍


✏️ Learnings added
Learnt from: groupthinking
URL: https://github.com/groupthinking/EventRelay/pull/1488

Timestamp: 2026-08-07T21:06:28.088Z
Learning: In `src/youtube_extension/backend/config/logging_config.py`, reproduce CPython 3.11's integer-to-string conversion-limit failure with an arithmetic value such as `10**4400`. Do not use `int("9" * 4301)`, because that conversion fails during test setup before the value reaches `StructuredFormatter._format_json`.

Note: Learnings are effective only in the context of similar code segments. To apply general coding guidelines, please configure review instructions. You can manage existing learnings in the app.

You are interacting with an AI system.

Copy link
Copy Markdown
Owner Author

Superseded — #1452 landed as #1491 while this was open, and this PR's change is the same base fallback that merged there. Nothing here is missing from main.

The residual holes in that merged fallback (forgeable isinstance filter, a re-raising serialization_error, non-finite floats emitting invalid JSON) are handled in #1497. Recommend closing this one.


Generated by Claude Code

… path

`test_last_resort_record_cannot_itself_fail_to_serialize` only parsed the
constant. It never called `_format_json`, so it would have passed unchanged
if the tier-3 `except` branch were deleted or made to re-raise -- a vacuous
guard on the one branch that makes the "never lost" claim unconditional.

Drive the real path instead: a filter poisons `process`, a *core* field that
tier 2 retains by design, so both tiers fail and the sink must receive the
constant record. Verified non-vacuous -- removing the tier-3 branch fails
this test and only this test (1 failed, 28 passed).

Raised by CodeRabbit on #1488.

Closes #1452

Copy link
Copy Markdown
Owner Author

Test gap closed in 1fa4f18

@coderabbitai agreed, and this was the right thing to push back on. test_last_resort_record_cannot_itself_fail_to_serialize asserted a property of a string constant, not of the code — it never called _format_json. A vacuous guard on the one branch whose entire purpose is to make the guarantee unconditional is worse than no guard, because it reads as coverage.

Implemented as you described: a logging.Filter sets record.process = 10**4400process is in _JSON_CORE_FIELDS, so tier 2 retains it by design and both tiers fail — then asserts the sink receives exactly _JSON_UNSERIALIZABLE_RECORD as one physical line.

Verified non-vacuous, and precisely so. Deleting the tier-3 except branch fails that test and nothing else:

FAILED test_last_resort_tier_is_reached_when_a_core_field_is_poisoned
1 failed, 28 passed

That is the exact regression a future edit would introduce — someone reading tiers 1 and 2 as sufficient and removing tier 3 as dead code — and it is now caught.

I kept the constant-parsing test alongside it. It is cheap and pins a different property (that the constant is valid JSON with a populated serialization_error), which the control-path test asserts only indirectly.

State on 1fa4f18

  • Focused suite: 29 passed — the 20 pre-existing tests unchanged.
  • Full unit suite delta vs origin/main: +9 passed, failures (311) and collection errors (66) byte-identical.
  • Lint: ruff clean on both changed files.
  • Every finding raised on this PR is now either fixed (oversized int, tier-3 vacuity) or tracked (JSON log records can emit a bare NaN/Infinity token, which strict parsers reject #1496, the allow_nan gap my red-team pass found — out of scope here, and sequenced to land after this PR so it degrades cleanly rather than turning a malformed record into a lost one).

Both of your findings were real and neither was in my own red-team battery. The oversized-int one in particular landed on the single sentence I had asserted could not fail — worth recording, because "provably cannot raise" is exactly the kind of claim this PR exists to stop shipping.

Awaiting CI on this head; terminal state remains HALTED(awaiting_merge_approval) — no automerge label and main is protected, so merge approval is the only step left.


Generated by Claude Code

@groupthinking

Copy link
Copy Markdown
Owner Author

Superseded by #1491 (merged 2026-08-07), which closed #1452 — same outcome (do not drop JSON log records on serialization failure). This PR is CONFLICTING with main and is a competing implementation of the same issue. Closing to clear the draft backlog.

@coderabbitai

coderabbitai Bot commented Aug 7, 2026

Copy link
Copy Markdown
Contributor

Tip

For best results, initiate chat on the files or code changes.

@groupthinking The new test addresses the gap.

test_last_resort_tier_is_reached_when_a_core_field_is_poisoned executes _format_json and forces the Tier 3 path. The non-vacuous check also verifies that Tier 3 remains required for the unconditional serialization-failure guarantee.

Keeping the constant-validity test is correct. It verifies the last-resort record content. The new test verifies the last-resort control path.

🐇✅


✏️ Learnings added
Learnt from: groupthinking
URL: https://github.com/groupthinking/EventRelay/pull/1488

Timestamp: 2026-08-07T21:14:01.087Z
Learning: When reviewing fallback error handling in `src/youtube_extension/backend/config/logging_config.py`, do not accept a “cannot raise” or unconditional record-delivery claim based only on type filtering or a constant-validity test. Require an end-to-end test that forces every earlier fallback tier to fail and verifies the final fallback record reaches the logging sink.

Note: Learnings are effective only in the context of similar code segments. To apply general coding guidelines, please configure review instructions. You can manage existing learnings in the app.


If you found this review helpful, would you consider giving us a shout-out on X?

Thank you for using CodeRabbit!

You are interacting with an AI system.

@github-actions

github-actions Bot commented Aug 7, 2026

Copy link
Copy Markdown

Dependency Review

✅ No vulnerabilities or license issues or OpenSSF Scorecard issues found.

Snapshot Warnings

⚠️: No snapshots were found for the head SHA 327804c.
Ensure that dependencies are being submitted on PR branches and consider enabling retry-on-snapshot-warnings. See the documentation for more information and troubleshooting advice.

Scanned Files

None

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Projects

None yet

Development

Successfully merging this pull request may close these issues.

default=str in _format_json does not deliver its stated guarantee — a record can still be lost (follow-up to #1439)

2 participants